Implement thread-safe logging. #427
Conversation
|
Hi @clalancette, thanks for taking us into account. IMO, this change will break compatibility with the micro-ROS stack for sure. But As far as most of the functionality is in a new .c and .h, it should be easy for us to avoid building them. Also, as far as micro-ROS does not have We can make a quick test next week to ensure micro-ROS functionality with this branch. CC: @Acuadros95 |
Ah, I didn't know about that. Thanks. (As a side note, it looks like at least some of the changes in those patches could probably be contributed back here.
Good to know, thanks.
That would be fantastic, thanks! |
|
Yeah, this kind of goes against the idea of avoiding use of system calls (env vars, mutex, threading, etc) in the lowest level libraries. I know we're not perfect on that score (especially for env vars), but it's a good guiding goal imo. It would be better (in my opinion), to have who ever initializes logging to provide a way to handle thread safety, a la dependency injection. On special OS/hardware combos that might mean no synchronization, and in C++ that might be std::mutex, in rclc that might be an OS specific mechanism, in another use case that might be a spin-lock (trading performance for other qualities), etc. I'll try to give the actual changes a review after lunch, but at least for now that's my general feeling for the approach. |
|
I would be happy if your rwlock here was a feature of rcutils, and was the default if nothing else was specified, but it was possible to avoid in favor of something else at initialization time of logging. |
I'll just point out that in our current system, this is tricky. The problem is that every logging call starts with a call to RCUTILS_LOGGING_AUTOINIT, so whichever module logs first initializes the logging subsystem. Maybe we should change that so we call Thoughts? |
|
Regarding micro-ROS: rclc is including Introducting thread-safe logging would not be a problem for the functionality of the rclc package per se. However, micro-ROS could be used in non-POSIX operating systems too, like AUTOSAR or bare-metal, which do not support Secondly, this locking could lead to further multi-threading issues, when the micro-ROS PR for multi-threading support and priority assignment will have been merged. Then, we will probably run into priority inversions or deadlocks, if callbacks are processed with different thread priorities and call rcutils logging API simultaneously. This pull request goes beyond the MultiThreadedExecutor capability of multi-threading, because it provides an API to assign a thread priority to callbacks directly. So callbacks can be executed by different thread priorities, which is currently not possible with ROS 2 API (alone). However, in ROS 2, people do create multiple threads outside ROS 2 and let Executors run with different thread priorities. Apart from micro-ROS, please also consider current PRs on ROS 2: PR to introduce a priority inheritance mutex:
PR to introduce thread creation independent of the operating system:
ROS Discourse post about real-time logging:
As a general comment, I think this topic is very important also for (a future) real-time support for ROS 2. This does not only require a real-time ROS 2 Executor and static memory allocation; but also topics like real-time logging, thread creation and configuration, priority inheritance mutex support, and other topics need to be addressed. To me, it is currently unclear, how this could be organized efficiently. Several PR have been made by the community as well as several publications have analysed the current limitations, but those improvements and new ideas need to be centrally reviewed and orchestrated so that they can find their way into the next ROS 2 release. |
This commit introduces thread-safe logging to rcutils. In particular, what it does is to add in a read-write lock around accesses to the g_rcutils_logging_severities_map in logging.c. This enables two things: 1. Thread-safe writes to the hash map so that get_logger_level and set_logger_level can be called simultaneously on two different threads. 2. The ability to cache lookups during get_logger_effective_level, so we have to do less parsing on every log call. This introduces the concept of locking into rcutils, which we haven't had before. However, this particular use seems to be justified, since the logging subsystem can be called outside of the client libraries that could possibly do this locking at a higher level (think about the rmw implementations, for instance). Note that this introduces a new pthread dependency within rcutils that we've not had before. Signed-off-by: Chris Lalancette <[email protected]>
It is much easier to follow this way. Signed-off-by: Chris Lalancette <[email protected]>
clalancette
force-pushed
the
clalancette/thread-safe-logging
branch
from
b50da00
to
ab44fc8
Compare
|
I've rebased this onto the latest, and also added in a bunch more detection logic here. It should now only attempt to build a pthread implementation when that is available, though it won't automatically build a "stub" implementation because that is inherently racy. I'm curious what people think of the latest here. |
This commit introduces thread-safe logging to rcutils. In particular, what it does is to add in a read-write lock around accesses to the g_rcutils_logging_severities_map in logging.c.
This enables two things:
This introduces the concept of locking into rcutils, which we haven't had before. However, this particular use seems to be justified, since the logging subsystem can be called outside of the client libraries that could possibly do this locking at a higher level (think about the rmw implementations, for instance).
Note that this introduces a new pthread dependency within rcutils that we've not had before.
If we take this, it will fix #397
@wjwwood @fujitatomoya @sloretz FYI, I'm interested to hear your thoughts about this.
@JanStaschulat @pablogs9 I'm interested to hear whether taking a pthread dependency like this will cause problems for e.g. rclc.